Skip to content

native interop: fix syslog on Apple arm64, stop starting getprop - #325

Merged
FreeAndNil merged 5 commits into
masterfrom
Feature/325-native-interop
Sep 25, 2026
Merged

FreeAndNil merged 5 commits into
masterfrom
Feature/325-native-interop

Conversation

@FreeAndNil

@FreeAndNil FreeAndNil commented Sep 21, 2026 •

Copy link
Copy Markdown
Contributor

Fixed

  • LocalSyslogAppender passed a variadic argument to syslog(3), audit da18b6f-f046
    • on Apple arm64 a variadic argument goes on the stack, a fixed one in a register, so the callee
      read a slot the runtime never wrote: stack bytes in the system log, or a crash
    • proved by a probe on macOS 26.6.2 arm64, green on Linux and x64
    • variadic is not an option, CoreCLR refuses a __arglist P/Invoke, so only the two fixed
      parameters are declared and the record goes in as the format string with every % doubled
    • logged text, record length and every platform that already worked are unchanged

Changed

  • Android detection started a process, audit da18b6f-f048
    • SystemInfo ran getprop ro.build.user at type initialisation on every Unix host, off PATH,
      so the first match there decided the answer
    • now /system/bin/getprop, and the platform itself off net462
  • The FormatMessage buffer was released by the wrong allocator, audit da18b6f-f045
    • the API allocates with LocalAlloc, the ref string marshalling freed it as COM task memory
    • now out IntPtr, PtrToStringUni over the returned length, LocalFree in a finally
    • hygiene, not a fix: a probe found the block inside the process heap

Tests

  • both probes are gone, each replaced by the regression test of its fix
  • the f048 and f046 tests fail against the old code; f045 has none, hence hygiene

FreeAndNil added a commit that referenced this pull request Sep 21, 2026
- SystemInfo ran "getprop ro.build.user" on every Unix host, via PATH
- first PATH match decided the answer
- now /system/bin/getprop, plus the platform itself off net462
- System.Diagnostics.Process out of the startup path

audit da18b6f-f048
@FreeAndNil
FreeAndNil force-pushed the Feature/325-native-interop branch from ed5e345 to 7842360 Compare September 21, 2026 20:15
FreeAndNil added a commit that referenced this pull request Sep 21, 2026
- process level env var tests restore through a using, not by hand
- ProcessLevelEnvironmentVariable leaked the variable on a failed assert
- Machine and User targets keep cleaning up themselves, not covered
FreeAndNil added a commit that referenced this pull request Sep 21, 2026
- FormatMessage allocates with LocalAlloc, the ref string marshalling
  freed it as COM task memory
- now out IntPtr, PtrToStringUni over the returned length, LocalFree in
  a finally
- hygiene, not a fix: the probe found the block inside the process heap
- WindowsAllocatorProbeTest replaced by NativeErrorTest

audit da18b6f-f045
FreeAndNil added a commit that referenced this pull request Sep 21, 2026
- a variadic argument goes on the stack on Apple arm64, a fixed one in a
  register, so the callee read the wrong slot
- declaring it variadic is out: CoreCLR refuses a __arglist P/Invoke
- only the two fixed parameters now, record as the format string with
  every percent sign doubled
- logged text, length and platforms that worked stay as they were
- VariadicAbiProbeTest replaced by the escaping and signature tests

audit da18b6f-f046
@FreeAndNil FreeAndNil changed the title Feature/325 native interop native interop: fix syslog on Apple arm64, stop starting getprop Sep 21, 2026
@FreeAndNil FreeAndNil added this to the 3.5.0 milestone Sep 22, 2026
@FreeAndNil
FreeAndNil changed the base branch from master to Feature/2.x September 24, 2026 08:38
@FreeAndNil
FreeAndNil changed the base branch from Feature/2.x to master September 24, 2026 08:38
- SystemInfo ran "getprop ro.build.user" on every Unix host, via PATH
- first PATH match decided the answer
- now /system/bin/getprop, plus the platform itself off net462
- System.Diagnostics.Process out of the startup path

audit da18b6f-f048
- process level env var tests restore through a using, not by hand
- ProcessLevelEnvironmentVariable leaked the variable on a failed assert
- Machine and User targets keep cleaning up themselves, not covered
- FormatMessage allocates with LocalAlloc, the ref string marshalling
  freed it as COM task memory
- now out IntPtr, PtrToStringUni over the returned length, LocalFree in
  a finally
- hygiene, not a fix: the probe found the block inside the process heap
- WindowsAllocatorProbeTest replaced by NativeErrorTest

audit da18b6f-f045
- a variadic argument goes on the stack on Apple arm64, a fixed one in a
  register, so the callee read the wrong slot
- declaring it variadic is out: CoreCLR refuses a __arglist P/Invoke
- only the two fixed parameters now, record as the format string with
  every percent sign doubled
- logged text, length and platforms that worked stay as they were
- VariadicAbiProbeTest replaced by the escaping and signature tests

audit da18b6f-f046
@FreeAndNil
FreeAndNil force-pushed the Feature/325-native-interop branch from 56334ea to 7202528 Compare September 24, 2026 09:12
@FreeAndNil
FreeAndNil marked this pull request as ready for review September 24, 2026 09:13
Comment thread src/log4net/Appender/LocalSyslogAppender.cs
@FreeAndNil

Copy link
Copy Markdown
Contributor Author

Implementation plan for #325, kept here for the record. Revised after the merge so that it describes the change as it landed.

Plan

PR #325: the native interop cluster

f045, f046 and f048 of scan da18b6fd, the three findings about P/Invoke and process interop.
None of them needs a platform we do not have: CI has Windows, macOS and Linux agents, and the
probes carried on the #324 branch answered the two open questions.

  • f048 (getprop) reproduces on this box.
  • f045 (FormatMessage allocator) came back green on Windows, so it is hygiene, not a live defect.
  • f046 (variadic syslog) came back red on macOS arm64, run 35646327969. The finding holds.

Branch Feature/325-native-interop off the current Feature/324-sinks-and-debug-echo tip while
#324 is open, or off master once it has merged; the pull request targets master. git switch -c from the local branch, never -b off a remote ref. Changelog entries are
src/changelog/3.5.0/325-*.xml with
<issue id="325" link="https://github.com/apache/logging-log4net/pull/325"/> and the attribution
(audit da18b6fd-fNNN, fixed by @FreeAndNil). The user commits; leave everything unstaged. Five
commits: the probes, f048, the environment variable test cleanup, f045, f046.

Commit 0: bring the probes over

"Probes for f045 & f046" lives on the #324 branch before its reset; cherry-pick it onto the new
branch by hash, no separate probes branch is needed. Both probes are replaced later in this branch,
so this commit exists only to keep their history attached to the findings they answer.

  • src/log4net.Tests/Util/VariadicAbiProbeTest.cs, [Platform("MacOsX,Linux")], red on Apple
    arm64 and green on Linux.
  • src/log4net.Tests/Util/WindowsAllocatorProbeTest.cs, [Platform("Win")], green.

Commit 1: f048, detect Android without running a process

SystemInfo.IsAndroidCore (src/log4net/Util/SystemInfo.cs:89) starts getprop ro.build.user
with FileName = "getprop", resolved through PATH. IsAndroid is a static field initialiser, so
this runs at type initialisation on every Unix host, before the static constructor body calls
GetAppSetting. Its only consumer is one branch of GetAppSetting.

Both cheap answers, in this order, and no process at all:

  1. File.Exists("/system/bin/getprop"), a file Android always has. First because it cannot throw.
  2. The platform's own answer, by target: OperatingSystem.IsAndroid() under #if NET, false
    under #elif NETFRAMEWORK since RuntimeInformation is not in net462 and Android never runs
    that asset, and RuntimeInformation.IsOSPlatform(OSPlatform.Create("ANDROID")) for
    netstandard2.0, wrapped in a guarded catch since IsOSPlatform throws below net471.
if (Environment.OSVersion.Platform != PlatformID.Unix)
{
  return false;
}

if (File.Exists("/system/bin/getprop"))
{
  return true;
}
// then the platform's own answer, per target, see above

What it buys beyond the finding: no process spawn at every Unix start, no PATH question to
mitigate, and System.Diagnostics.Process out of the startup path, which AotCompatibilityTest
and the AOT probes in CI care about.

Test, AndroidDetectionDoesNotRunGetpropFromThePath in src/log4net.Tests/Util/SystemInfoTest.cs,
[Platform("Linux,MacOsX")] [NonParallelizable] because it mutates PATH:

  • Write an executable named getprop into an AutoTempFolder that creates a marker file, made
    executable with File.SetUnixFileMode under #if NET; prepend that folder to PATH with
    using AutoTempEnvironmentVariable, which restores it; call IsAndroidCore by reflection
    through a small helper that throws a clear message if the method is renamed.
  • The result must be false and the marker must not appear. Against the old code the marker appears
    and the result is true, which is the revert-to-red check and also demonstrates the hijack.
  • IsAndroid is cached, so the test calls IsAndroidCore, not the property.

Changelog 325-android-detection-without-getprop.xml, type="changed".

Commit 1b: restore environment variables through a using

While there, the two process-level environment variable tests in EnvironmentPatternConverterTest
and SystemInfoTest set and reset the variable by hand, and the first leaked it on a failed
assertion. Both take using AutoTempEnvironmentVariable from PeanutButter.Utils instead. The
Machine and User targets keep cleaning up themselves, the helper covers only the process level.
Record the rule in the agent instructions.

Commit 2: f045, release the FormatMessage buffer with LocalFree

NativeMethods.FormatMessage (src/log4net/Util/NativeMethods.cs:129) is declared with
ref string lpBuffer and called with FORMAT_MESSAGE_ALLOCATE_BUFFER from
NativeError.GetErrorMessage (src/log4net/Util/NativeError.cs:114). The API allocates with
LocalAlloc, the marshaller frees as COM task memory.

Answered by the #324 run: the Windows job is green, so WindowsAllocatorProbeTest found the
LocalAlloc block inside the process heap, and the production path survived 500 passes. Freeing it
as COM task memory therefore hits the same heap on current Windows, which makes f045 hygiene rather
than a live heap defect. Say that in the changelog and do not call it a vulnerability.

Either way the correct shape is the same. src/log4net/Util/NativeMethods.cs, keeping that file's
block-scoped namespace and its existing doc comment, of which only the lpBuffer paragraph
changes to say the caller releases the buffer with LocalFree:

internal static extern int FormatMessage(
  int dwFlags, IntPtr lpSource, int dwMessageId, int dwLanguageId,
  out IntPtr lpBuffer, int nSize, IntPtr arguments);

[DllImport("Kernel32.dll", SetLastError = true)]
[DefaultDllImportSearchPaths(DllImportSearchPath.System32)]
internal static extern IntPtr LocalFree(IntPtr memory);

lpSource drops its pointless ref at the same time; the caller only ever passed a zero.

NativeError.GetErrorMessage returns null for messageId == 0 before calling out, otherwise reads
the text with Marshal.PtrToStringUni(buffer, messageSize), using the returned character count
rather than trusting a terminator, trims the trailing newlines, and releases the buffer with
NativeMethods.LocalFree in a finally guarded against a zero pointer. The three Win32 flag
constants stay as they are.

Test, new src/log4net.Tests/Util/NativeErrorTest.cs, [TestFixture] [Platform("Win")], which is
what WindowsAllocatorProbeTest becomes, all expression bodied but the loop:

  • GetErrorMessage(2) equals new Win32Exception(2).Message, the BCL's own FormatMessage call,
    so the oracle is locale-neutral. Compare with the trailing period trimmed on both sides: .NET
    Framework strips it, log4net and .NET do not.
  • No trailing \r or \n.
  • GetErrorMessage(0) is null.
  • 500 repeats return the identical non-empty string, carried over from the probe: a heap the wrong
    free had corrupted shows up here.
  • GetError(2).ToString() carries the hex number and the message.

Delete WindowsAllocatorProbeTest.cs in this commit, so Windows stays covered by the real test.
There is no test that fails against the old code, which is what makes this hygiene.

Changelog 325-formatmessage-buffer-release.xml, type="changed": it is hygiene, not a fix for an
observed failure.

Commit 3: f046, drop the variadic argument from the syslog call

NativeMethods.syslog declares void syslog(int, string, string) against the variadic libc
function. On Apple arm64 varargs travel differently from fixed arguments.

Answered, and the finding holds. On the #324 run 35646327969 the macOS job failed with

audit da18b6fd-f046 confirmed: macOS 26.6.2, Arm64, wrote 5 bytes [25637]
Expected: "12345"
But was:  "25637"

The argument was passed in a register, the callee read it off the stack. The same probe passes on
Linux x64 locally, which is the control, and the ubuntu job of that run was cancelled before it got
there. So the divergence is Apple arm64, not the declaration being wrong everywhere. With %s,
which is what LocalSyslogAppender uses, the garbage the callee reads is a pointer, so the failure
mode is a crash or stack bytes in the system log rather than a wrong number.

Declaring it variadic is not available: CoreCLR answers a __arglist P/Invoke with
InvalidProgramException: Vararg calling convention not supported. Chosen fix: pass no variadic
argument at all
, rather than refusing the appender on Apple arm64 or taking a second native entry
point. priority and format are the two fixed parameters of syslog, and fixed parameters are
passed identically under both conventions on every ABI, so a two-parameter declaration is correct
everywhere. The rendered message becomes the format string, with every % doubled:

// NativeMethods.cs
internal static extern void syslog(int priority, string format);

// LocalSyslogAppender.Append
NativeMethods.syslog(priority, EscapePercent(line));

private static string EscapePercent(string message)
  => message.IndexOf('%') < 0 ? message : message.Replace("%", "%%");
  • Both call sites in Append (src/log4net/Appender/LocalSyslogAppender.cs, the Split loop and
    the single-record path) go through EscapePercent, applied last, after EscapeNulCharacters and
    EscapeNewLines. The comment that called the second argument a printf format string goes.
  • EscapePercent is a private helper on the appender next to EscapeNewLines, not a new
    ContentEscape member: it is printf quoting, invisible in the output, not a visible escape for a
    character the sink cannot carry.
  • Update the <remarks> on the syslog declaration, which currently tells the caller to pass
    "%s": only the two fixed parameters are declared, the caller doubles every %.
  • The escaping is security-relevant now: content that reaches the format string unescaped is a
    format string bug. Replace covers every occurrence, and the tests pin it.

Tests in src/log4net.Tests/Appender/LocalSyslogAppenderTest.cs, reflecting onto EscapePercent
the way that fixture already does for EscapeNewLines, and replacing VariadicAbiProbeTest:

  • EveryPercentSignIsEscaped, [TestCase]s shortest to longest: "%s" to "%%s", "100%" to
    "100%%", "%d%n" to "%%d%%n", "rate=%s of %d" to "rate=%%s of %%d"; and
    MessagesWithoutPercentSignsAreUnchanged for the fast path. Red before the fix, the helper
    does not exist.
  • TheSyslogDeclarationPassesNoVariadicArgument: a reflection assertion that
    NativeMethods.syslog declares exactly two parameters, int and string, so the variadic
    argument cannot be reintroduced unnoticed. Cross-platform.
  • ContentThatLooksLikeAFormatStringIsLogged, [Platform("Linux")] [NonParallelizable]:
    activate an appender and append an event whose rendered message holds %s %n %x %99999$s, and
    assert the call returns without throwing. Not an output assertion, syslog(3) cannot be read
    back, but it exercises the new declaration natively with the worst content.

Delete VariadicAbiProbeTest.cs here. Honest limit for the commit message: the ABI half of this
cannot go red on Linux, where the two conventions coincide. The macOS agent is the witness, and the
new shape has to come back green there.

Changelog 325-syslog-apple-arm64.xml, type="fixed".

Verification

dotnet build src/log4net.sln                                              # 0 warnings, both TFMs
dotnet build src/log4net.Tests/log4net.Tests.csproj -f net462 -p:TargetFrameworks=net462
dotnet test  src/log4net.Tests/log4net.Tests.csproj -f net10.0
dotnet test  src/log4net.Ext.Mail.Tests/log4net.Ext.Mail.Tests.csproj
  • Redirect build output to a file and read it whole; do not pipe MSBuild through grep.
  • Per commit, revert the production change in place, no stash, and confirm the new test fails,
    except for f045, which has no failing test, and the f046 ABI assertion noted above.
  • The Windows and macOS answers come from CI, not from this box.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants